/* 
   AP_Logger logging - file oriented variant

   This uses posix file IO to create log files called logs/NN.bin in the
   given directory

   SD Card Rates on PixHawk:
    - deletion rate seems to be ~50 files/second.
    - stat seems to be ~150/second
    - readdir loop of 511 entry directory ~62,000 microseconds
 */

#include "AP_Logger_config.h"

#if HAL_LOGGING_FILESYSTEM_ENABLED

#include <AP_HAL/AP_HAL.h>
#include <AP_Filesystem/AP_Filesystem.h>
#if AP_FILESYSTEM_LITTLEFS_ENABLED
#include <AP_Filesystem/AP_Filesystem_FlashMemory_LittleFS.h>
#endif

#include "AP_Logger.h"
#include "AP_Logger_File.h"

#include <AP_Common/AP_Common.h>
#include <AP_InternalError/AP_InternalError.h>
#include <AP_RTC/AP_RTC.h>
#include <AP_Vehicle/AP_Vehicle_Type.h>
#include <AP_AHRS/AP_AHRS.h>

#include <AP_Math/AP_Math.h>
#include <GCS_MAVLink/GCS.h>
#include <stdio.h>


extern const AP_HAL::HAL& hal;

#define LOGGER_PAGE_SIZE 1024UL

#define MB_to_B 1000000
#define B_to_MB 0.000001

// time between tries to open log
#define LOGGER_FILE_REOPEN_MS 5000

/*
  constructor
 */
AP_Logger_File::AP_Logger_File(AP_Logger &front,
                               LoggerMessageWriter_DFLogStart *writer) :
    AP_Logger_Backend(front, writer),
    _log_directory(HAL_BOARD_LOG_DIRECTORY)
{
    df_stats_clear();
}


void AP_Logger_File::ensure_log_directory_exists()
{
    int ret;
    struct stat st;

    EXPECT_DELAY_MS(3000);
    ret = AP::FS().stat(_log_directory, &st);
    if (ret == -1) {
        ret = AP::FS().mkdir(_log_directory);
    }
    if (ret == -1 && errno != EEXIST) {
        GCS_SEND_TEXT(MAV_SEVERITY_WARNING, "Failed to create log directory %s : %s", _log_directory, strerror(errno));
    }
}

void AP_Logger_File::Init()
{
    // determine and limit file backend buffersize
    uint32_t bufsize = _front._params.file_bufsize;
    bufsize *= 1024;

    const uint32_t desired_bufsize = bufsize;

    // If we can't allocate the full size, try to reduce it until we can allocate it
    while (!_writebuf.set_size(bufsize) && bufsize >= _writebuf_chunk) {
        bufsize *= 0.9;
    }
    if (bufsize >= _writebuf_chunk && bufsize != desired_bufsize) {
        DEV_PRINTF("AP_Logger: reduced buffer %u/%u\n", (unsigned)bufsize, (unsigned)desired_bufsize);
    }

    if (!_writebuf.get_size()) {
        DEV_PRINTF("Out of memory for logging\n");
        return;
    }

    DEV_PRINTF("AP_Logger_File: buffer size=%u\n", (unsigned)bufsize);

    _initialised = true;

    const char* custom_dir = hal.util->get_custom_log_directory();
    if (custom_dir != nullptr){
        _log_directory = custom_dir;
    }

    uint16_t last_log_num = find_last_log();
    if (last_log_is_marked_discard) {
        // delete the last log leftover from LOG_DISARMED=3
        char *filename = _log_file_name(last_log_num);
        if (filename != nullptr) {
            AP::FS().unlink(filename);
            free(filename);
        }
    }

    Prep_MinSpace();
}

bool AP_Logger_File::file_exists(const char *filename) const
{
    struct stat st;
    EXPECT_DELAY_MS(3000);
    if (AP::FS().stat(filename, &st) == -1) {
        // hopefully errno==ENOENT.  If some error occurs it is
        // probably better to assume this file exists.
        return false;
    }
    return true;
}

bool AP_Logger_File::log_exists(const uint16_t lognum) const
{
    char *filename = _log_file_name(lognum);
    if (filename == nullptr) {
        return false; // ?!
    }
    bool ret = file_exists(filename);
    free(filename);
    return ret;
}

void AP_Logger_File::periodic_1Hz()
{
    AP_Logger_Backend::periodic_1Hz();

    if (_initialised &&
        _write_fd == -1 && _read_fd == -1 &&
        erase.log_num == 0 &&
        erase.was_logging) {
        // restart logging after an erase if needed
        erase.was_logging = false;
        // setup to open the log in the backend thread
        start_new_log_pending = true;
    }
    
    if (_initialised &&
        !start_new_log_pending &&
        _write_fd == -1 && _read_fd == -1 &&
        logging_enabled() &&
        !recent_open_error()) {
        // setup to open the log in the backend thread
        start_new_log_pending = true;
    }

    if (!io_thread_alive()) {
        if (io_thread_warning_decimation_counter == 0 && _initialised) {
            // we don't print this error unless we did initialise. When _initialised is set to true
            // we register the IO timer callback
            GCS_SEND_TEXT(MAV_SEVERITY_CRITICAL, "AP_Logger: stuck thread (%s)", last_io_operation);
        }
        if (io_thread_warning_decimation_counter++ > 30) {
            io_thread_warning_decimation_counter = 0;
        }
    }

    if (rate_limiter == nullptr &&
        (_front._params.file_ratemax > 0 ||
         _front._params.disarm_ratemax > 0 ||
         _front._log_pause)) {
        // setup rate limiting if log rate max > 0Hz or log pause of streaming entries is requested
        rate_limiter = NEW_NOTHROW AP_Logger_RateLimiter(_front, _front._params.file_ratemax, _front._params.disarm_ratemax);
    }
}

void AP_Logger_File::periodic_fullrate()
{
    AP_Logger_Backend::push_log_blocks();
}

uint32_t AP_Logger_File::bufferspace_available()
{
    const uint32_t space = _writebuf.space();
    const uint32_t crit = critical_message_reserved_space(_writebuf.get_size());

    return (space > crit) ? space - crit : 0;
}

bool AP_Logger_File::recent_open_error(void) const
{
    if (_open_error_ms == 0) {
        return false;
    }
    return AP_HAL::millis() - _open_error_ms < LOGGER_FILE_REOPEN_MS;
}

// return true for CardInserted() if we successfully initialized
bool AP_Logger_File::CardInserted(void) const
{
    return _initialised && !recent_open_error();
}

// returns the amount of disk space available in _log_directory (in bytes)
// returns -1 on error
int64_t AP_Logger_File::disk_space_avail()
{
    return AP::FS().disk_free(_log_directory);
}

// returns the total amount of disk space (in use + available) in
// _log_directory (in bytes).
// returns -1 on error
int64_t AP_Logger_File::disk_space()
{
    return AP::FS().disk_space(_log_directory);
}

/*
  convert a dirent to a log number
 */
bool AP_Logger_File::dirent_to_log_num(const dirent *de, uint16_t &log_num) const
{
    uint8_t length = strlen(de->d_name);
    if (length < 5) {
        return false;
    }
    if (strncmp(&de->d_name[length-4], ".BIN", 4) != 0) {
        // doesn't end in .BIN
        return false;
    }

    uint16_t thisnum = strtoul(de->d_name, nullptr, 10);
    if (thisnum > _front.get_max_num_logs()) {
        return false;
    }
    log_num = thisnum;
    return true;
}


// find_oldest_log - find oldest log in _log_directory
// returns 0 if no log was found
uint16_t AP_Logger_File::find_oldest_log()
{
    if (_cached_oldest_log != 0) {
        return _cached_oldest_log;
    }

    uint16_t last_log_num = find_last_log();
    if (last_log_num == 0) {
        return 0;
    }

    uint16_t current_oldest_log = 0; // 0 is invalid

    // We could count up to find_last_log(), but if people start
    // relying on the min_avail_space_percent feature we could end up
    // doing a *lot* of asprintf()s and stat()s
    EXPECT_DELAY_MS(3000);
    auto *d = AP::FS().opendir(_log_directory);
    if (d == nullptr) {
        // SD card may have died?  On linux someone may have rm-rf-d
        return 0;
    }

    // we only remove files which look like xxx.BIN
    EXPECT_DELAY_MS(3000);
    for (struct dirent *de=AP::FS().readdir(d); de; de=AP::FS().readdir(d)) {
        EXPECT_DELAY_MS(3000);
        uint16_t thisnum;
        if (!dirent_to_log_num(de, thisnum)) {
            // not a log filename
            continue;
        }
        if (current_oldest_log == 0) {
            current_oldest_log = thisnum;
        } else {
            if (current_oldest_log <= last_log_num) {
                if (thisnum > last_log_num) {
                    current_oldest_log = thisnum;
                } else if (thisnum < current_oldest_log) {
                    current_oldest_log = thisnum;
                }
            } else { // current_oldest_log > last_log_num
                if (thisnum > last_log_num) {
                    if (thisnum < current_oldest_log) {
                        current_oldest_log = thisnum;
                    }
                }
            }
        }
    }
    AP::FS().closedir(d);
    _cached_oldest_log = current_oldest_log;

    return current_oldest_log;
}

void AP_Logger_File::Prep_MinSpace()
{
    if (hal.util->was_watchdog_reset()) {
        // don't clear space if watchdog reset, it takes too long
        return;
    }

    if (!CardInserted()) {
        return;
    }

    const uint16_t first_log_to_remove = find_oldest_log();
    if (first_log_to_remove == 0) {
        // no files to remove
        return;
    }

    const int64_t target_free = (int64_t)_front._params.min_MB_free * MB_to_B;

    uint16_t log_to_remove = first_log_to_remove;

    uint16_t count = 0;
    do {
        int64_t avail = disk_space_avail();
        if (avail == -1) {
            break;
        }
        if (avail >= target_free) {
            break;
        }
        if (count++ > _front.get_max_num_logs() + 10) {
            // *way* too many deletions going on here.  Possible internal error.
            INTERNAL_ERROR(AP_InternalError::error_t::logger_too_many_deletions);
            break;
        }
        char *filename_to_remove = _log_file_name(log_to_remove);
        if (filename_to_remove == nullptr) {
            INTERNAL_ERROR(AP_InternalError::error_t::logger_bad_getfilename);
            break;
        }
        if (file_exists(filename_to_remove)) {
            DEV_PRINTF("Removing (%s) for minimum-space requirements (%.0fMB < %.0fMB)\n",
                                filename_to_remove, (double)avail*B_to_MB, (double)target_free*B_to_MB);
            EXPECT_DELAY_MS(2000);
            if (AP::FS().unlink(filename_to_remove) == -1) {
                _cached_oldest_log = 0;
                DEV_PRINTF("Failed to remove %s: %s\n", filename_to_remove, strerror(errno));
                free(filename_to_remove);
                if (errno == ENOENT) {
                    // corruption - should always have a continuous
                    // sequence of files...  however, there may be still
                    // files out there, so keep going.
                } else {
                    break;
                }
            } else {
                free(filename_to_remove);
            }
        }
        log_to_remove++;
        if (log_to_remove > _front.get_max_num_logs()) {
            log_to_remove = 1;
        }
    } while (log_to_remove != first_log_to_remove);
}

/*
  construct a log file name given a log number.
  The number in the log filename will be zero-padded.
  Note: Caller must free.
 */
char *AP_Logger_File::_log_file_name(const uint16_t log_num) const
{
    char *buf = nullptr;
    if (asprintf(&buf, "%s/%08u.BIN", _log_directory, (unsigned)log_num) == -1) {
        return nullptr;
    }
    return buf;
}

/*
  return path name of the lastlog.txt marker file
  Note: Caller must free.
 */
char *AP_Logger_File::_lastlog_file_name(void) const
{
    char *buf = nullptr;
    if (asprintf(&buf, "%s/LASTLOG.TXT", _log_directory) == -1) {
        return nullptr;
    }
    return buf;
}


// remove all log files
void AP_Logger_File::EraseAll()
{
    if (hal.util->get_soft_armed()) {
        // do not want to do any filesystem operations while we are e.g. flying
        return;
    }
    if (!_initialised) {
        return;
    }

    erase.was_logging = (_write_fd != -1);
    stop_logging();

    erase.log_num = 1;
}

bool AP_Logger_File::WritesOK() const
{
    if (_write_fd == -1) {
        return false;
    }
    if (recent_open_error()) {
        return false;
    }
    return true;
}


bool AP_Logger_File::StartNewLogOK() const
{
    if (recent_open_error()) {
        return false;
    }
#if !APM_BUILD_TYPE(APM_BUILD_Replay) && !APM_BUILD_TYPE(APM_BUILD_UNKNOWN)
    if (hal.scheduler->in_main_thread()) {
        return false;
    }
#endif
    return AP_Logger_Backend::StartNewLogOK();
}

/* Write a block of data at current offset */
bool AP_Logger_File::_WritePrioritisedBlock(const void *pBuffer, uint16_t size, bool is_critical)
{
    WITH_SEMAPHORE(semaphore);

#if APM_BUILD_TYPE(APM_BUILD_Replay)
    if (AP::FS().write(_write_fd, pBuffer, size) != size) {
        AP_HAL::panic("Short write");
    }
    return true;
#endif


    uint32_t space = _writebuf.space();

    if (_writing_startup_messages &&
        _startup_messagewriter->fmt_done()) {
        // the state machine has called us, and it has finished
        // writing format messages out.  It can always get back to us
        // with more messages later, so let's leave room for other
        // things:
        const uint32_t now = AP_HAL::millis();
        const bool must_dribble = (now - last_messagewrite_message_sent) > 100;
        if (!must_dribble &&
            space < non_messagewriter_message_reserved_space(_writebuf.get_size())) {
            // this message isn't dropped, it will be sent again...
            return false;
        }
        last_messagewrite_message_sent = now;
    } else {
        // we reserve some amount of space for critical messages:
        if (!is_critical && space < critical_message_reserved_space(_writebuf.get_size())) {
            _dropped++;
            return false;
        }
    }

    // if no room for entire message - drop it:
    if (space < size) {
        _dropped++;
        return false;
    }

    _writebuf.write((uint8_t*)pBuffer, size);
    df_stats_gather(size, _writebuf.space());
    return true;
}

/*
  find the highest log number
 */
uint16_t AP_Logger_File::find_last_log()
{
    unsigned ret = 0;
    char *fname = _lastlog_file_name();
    if (fname == nullptr) {
        return ret;
    }
    EXPECT_DELAY_MS(3000);
    FileData *fd = AP::FS().load_file(fname);
    free(fname);
    last_log_is_marked_discard = false;
    if (fd != nullptr) {
        char *endptr = nullptr;
        ret = strtol((const char *)fd->data, &endptr, 10);
        if (endptr != nullptr) {
            last_log_is_marked_discard = *endptr == 'D';
        }
        delete fd;
    }
    return ret;
}

uint32_t AP_Logger_File::_get_log_size(const uint16_t log_num)
{
    char *fname = _log_file_name(log_num);
    if (fname == nullptr) {
        return 0;
    }
    if (_write_fd != -1 && write_fd_semaphore.take_nonblocking()) {
        if (_write_filename != nullptr && strcmp(_write_filename, fname) == 0) {
            // it is the file we are currently writing
            free(fname);
            write_fd_semaphore.give();
            return _write_offset;
        }
        write_fd_semaphore.give();
    }
    struct stat st;
    EXPECT_DELAY_MS(3000);
    if (AP::FS().stat(fname, &st) != 0) {
        free(fname);
        return 0;
    }
    free(fname);
    return st.st_size;
}

uint32_t AP_Logger_File::_get_log_time(const uint16_t log_num)
{
    char *fname = _log_file_name(log_num);
    if (fname == nullptr) {
        return 0;
    }
    if (_write_fd != -1 && write_fd_semaphore.take_nonblocking()) {
        if (_write_filename != nullptr && strcmp(_write_filename, fname) == 0) {
            // it is the file we are currently writing
            free(fname);
            write_fd_semaphore.give();
#if AP_RTC_ENABLED
            uint64_t utc_usec;
            if (!AP::rtc().get_utc_usec(utc_usec)) {
                return 0;
            }
            return utc_usec / 1000000U;
#else
            return 0;
#endif
        }
        write_fd_semaphore.give();
    }
    struct stat st;
    EXPECT_DELAY_MS(3000);
    if (AP::FS().stat(fname, &st) != 0) {
        free(fname);
        return 0;
    }
    free(fname);
    return st.st_mtime;
}

/*
  find the number of pages in a log
 */
void AP_Logger_File::get_log_boundaries(const uint16_t list_entry, uint32_t & start_page, uint32_t & end_page)
{
    const uint16_t log_num = log_num_from_list_entry(list_entry);
    if (log_num == 0) {
        // that failed - probably no logs
        start_page = 0;
        end_page = 0;
        return;
    }

    start_page = 0;
    end_page = _get_log_size(log_num) / LOGGER_PAGE_SIZE;
}

/*
  retrieve data from a log file
 */
int16_t AP_Logger_File::get_log_data(const uint16_t list_entry, const uint16_t page, const uint32_t offset, const uint16_t len, uint8_t *data)
{
    if (!_initialised || recent_open_error()) {
        return -1;
    }

    const uint16_t log_num = log_num_from_list_entry(list_entry);
    if (log_num == 0) {
        // that failed - probably no logs
        return -1;
    }

    if (_read_fd != -1 && log_num != _read_fd_log_num) {
        AP::FS().close(_read_fd);
        _read_fd = -1;
    }
    if (_read_fd == -1) {
        char *fname = _log_file_name(log_num);
        if (fname == nullptr) {
            return -1;
        }
        stop_logging();
        EXPECT_DELAY_MS(3000);
        _read_fd = AP::FS().open(fname, O_RDONLY);
        if (_read_fd == -1) {
            _open_error_ms = AP_HAL::millis();
            int saved_errno = errno;
            ::printf("Log read open fail for %s - %s\n",
                     fname, strerror(saved_errno));
            DEV_PRINTF("Log read open fail for %s - %s\n",
                                fname, strerror(saved_errno));
            free(fname);
            return -1;            
        }
        free(fname);
        _read_offset = 0;
        _read_fd_log_num = log_num;
    }
    uint32_t ofs = page * (uint32_t)LOGGER_PAGE_SIZE + offset;

    if (ofs != _read_offset) {
        if (AP::FS().lseek(_read_fd, ofs, SEEK_SET) == (off_t)-1) {
            AP::FS().close(_read_fd);
            _read_fd = -1;
            return -1;
        }
        _read_offset = ofs;
    }
    int16_t ret = (int16_t)AP::FS().read(_read_fd, data, len);
    if (ret > 0) {
        _read_offset += ret;
    }
    return ret;
}

void AP_Logger_File::end_log_transfer()
{
    if (_read_fd != -1) {
        AP::FS().close(_read_fd);
        _read_fd = -1;
    }
}

/*
  find size and date of a log
 */
void AP_Logger_File::get_log_info(const uint16_t list_entry, uint32_t &size, uint32_t &time_utc)
{
    uint16_t log_num = log_num_from_list_entry(list_entry);
    if (log_num == 0) {
        // that failed - probably no logs
        size = 0;
        time_utc = 0;
        return;
    }

    size = _get_log_size(log_num);
    time_utc = _get_log_time(log_num);
}


/*
  get the number of logs - note that the log numbers must be consecutive
 */
uint16_t AP_Logger_File::get_num_logs()
{
    auto *d = AP::FS().opendir(_log_directory);
    if (d == nullptr) {
        return 0;
    }
    uint16_t high = find_last_log();
    uint16_t ret = high;
    uint16_t smallest_above_last = 0;

    EXPECT_DELAY_MS(2000);
    for (struct dirent *de=AP::FS().readdir(d); de; de=AP::FS().readdir(d)) {
        EXPECT_DELAY_MS(100);
        uint16_t thisnum;
        if (!dirent_to_log_num(de, thisnum)) {
            // not a log filename
            continue;
        }

        if (thisnum > high && (smallest_above_last == 0 || thisnum < smallest_above_last)) {
            smallest_above_last = thisnum;
        }
    }
    AP::FS().closedir(d);
    if (smallest_above_last != 0) {
        // we have wrapped, add in the logs with high numbers
        ret += (_front.get_max_num_logs() - smallest_above_last) + 1;
    }

    return ret;
}

/*
  stop logging
 */
void AP_Logger_File::stop_logging(void)
{
    // best-case effort to avoid annoying the IO thread
    const bool have_sem = write_fd_semaphore.take(hal.util->get_soft_armed()?1:20);
    if (_write_fd != -1) {
        int fd = _write_fd;
        _write_fd = -1;
        AP::FS().close(fd);
    }
    if (have_sem) {
        write_fd_semaphore.give();
    }
}

/*
  does start_new_log in the logger thread
 */
void AP_Logger_File::PrepForArming_start_logging()
{
    if (logging_started()) {
        return;
    }

    uint32_t start_ms = AP_HAL::millis();
    const uint32_t open_limit_ms = 1000;

    /*
      log open happens in the io_timer thread. We allow for a maximum
      of 1s to complete the open
     */
    start_new_log_pending = true;
    EXPECT_DELAY_MS(1000);
    while (AP_HAL::millis() - start_ms < open_limit_ms) {
        if (logging_started()) {
            break;
        }
#if !APM_BUILD_TYPE(APM_BUILD_Replay) && AP_AHRS_ENABLED
        // keep the EKF ticking over
        AP::ahrs().update();
#endif
        hal.scheduler->delay(1);
    }
}

/*
  start writing to a new log file
 */
void AP_Logger_File::start_new_log(void)
{
    if (recent_open_error()) {
        // we have previously failed to open a file - don't try again
        // to prevent us trying to open files while in flight
        return;
    }

    if (erase.log_num != 0) {
        // don't start a new log while erasing, but record that we
        // want to start logging when erase finished
        erase.was_logging = true;
        return;
    }

    const bool open_error_ms_was_zero = (_open_error_ms == 0);

    // set _open_error here to avoid infinite recursion.  Simply
    // writing a prioritised block may try to open a log - which means
    // if anything in the start_new_log path does a GCS_SEND_TEXT()
    // (for example), you will end up recursing if we don't take
    // precautions.  We will reset _open_error if we actually manage
    // to open the log...
    _open_error_ms = AP_HAL::millis();

    stop_logging();

    start_new_log_reset_variables();

    if (_read_fd != -1) {
        AP::FS().close(_read_fd);
        _read_fd = -1;
    }

    if (disk_space_avail() < _free_space_min_avail && disk_space() > 0) {
        DEV_PRINTF("Out of space for logging\n");
        return;
    }

    uint16_t log_num = find_last_log();
    // re-use empty logs if possible
    if (_get_log_size(log_num) > 0 || log_num == 0) {
        log_num++;
    }
    if (log_num > _front.get_max_num_logs()) {
        log_num = 1;
    }
    if (!write_fd_semaphore.take(1)) {
        return;
    }
    if (_write_filename) {
        free(_write_filename);
        _write_filename = nullptr;        
    }
    _write_filename = _log_file_name(log_num);
    if (_write_filename == nullptr) {
        write_fd_semaphore.give();
        return;
    }

#if CONFIG_HAL_BOARD == HAL_BOARD_CHIBIOS
    // remember if we had utc time when we opened the file
#if AP_RTC_ENABLED
    uint64_t utc_usec;
    _need_rtc_update = !AP::rtc().get_utc_usec(utc_usec);
#endif
#endif

    // create the log directory if need be
    ensure_log_directory_exists();

    EXPECT_DELAY_MS(3000);
    _write_fd = AP::FS().open(_write_filename, O_WRONLY|O_CREAT|O_TRUNC);
    _cached_oldest_log = 0;

    if (_write_fd == -1) {
        write_fd_semaphore.give();
        int saved_errno = errno;
        if (open_error_ms_was_zero) {
            ::printf("Log open fail for %s - %s\n",
                     _write_filename, strerror(saved_errno));
            DEV_PRINTF("Log open fail for %s - %s\n",
                                _write_filename, strerror(saved_errno));
        }
        return;
    }
    _last_write_ms = AP_HAL::millis();
    _open_error_ms = 0;
    _write_offset = 0;
    _writebuf.clear();
    write_fd_semaphore.give();

    // now update lastlog.txt with the new log number
    last_log_is_marked_discard = _front._params.log_disarmed == AP_Logger::LogDisarmed::LOG_WHILE_DISARMED_DISCARD;
    if (!write_lastlog_file(log_num)) {
        _open_error_ms = AP_HAL::millis();
    }
}

/*
  write LASTLOG.TXT, possibly with a discard marker
 */
bool AP_Logger_File::write_lastlog_file(uint16_t log_num)
{
    // now update lastlog.txt with the new log number
    char *fname = _lastlog_file_name();

    EXPECT_DELAY_MS(3000);
    int fd = AP::FS().open(fname, O_WRONLY|O_CREAT);
    free(fname);
    if (fd == -1) {
        return false;
    }

    char buf[30];
    snprintf(buf, sizeof(buf), "%u%s\r\n", (unsigned)log_num, last_log_is_marked_discard?"D":"");
    const ssize_t to_write = strlen(buf);
    const ssize_t written = AP::FS().write(fd, buf, to_write);
    AP::FS().close(fd);
    return written == to_write;
}

#if CONFIG_HAL_BOARD == HAL_BOARD_SITL || CONFIG_HAL_BOARD == HAL_BOARD_LINUX
void AP_Logger_File::flush(void)
#if APM_BUILD_TYPE(APM_BUILD_Replay) || APM_BUILD_TYPE(APM_BUILD_UNKNOWN)
{
    uint32_t tnow = AP_HAL::millis();
    while (_write_fd != -1 && _initialised && !recent_open_error() && _writebuf.available()) {
        // convince the IO timer that it really is OK to write out
        // less than _writebuf_chunk bytes:
        if (tnow > 2001) { // avoid resetting _last_write_time to 0
            _last_write_time = tnow - 2001;
        }
        io_timer();
    }
    if (write_fd_semaphore.take(1)) {
        if (_write_fd != -1) {
            ::fsync(_write_fd);
        }
        write_fd_semaphore.give();
    } else {
        INTERNAL_ERROR(AP_InternalError::error_t::logger_flushing_without_sem);
    }
}
#else
{
    // flush is for replay and examples only
}
#endif // APM_BUILD_TYPE(APM_BUILD_Replay) || APM_BUILD_TYPE(APM_BUILD_UNKNOWN)
#endif

void AP_Logger_File::io_timer(void)
{
    uint32_t tnow = AP_HAL::millis();
    _io_timer_heartbeat = tnow;

    if (start_new_log_pending) {
        start_new_log();
        start_new_log_pending = false;
    }

    if (erase.log_num != 0) {
        // continue erase
        erase_next();
        return;
    }

    if (_write_fd == -1 || !_initialised || recent_open_error()) {
        return;
    }

    if (last_log_is_marked_discard && hal.util->get_soft_armed()) {
        // time to make the log permanent
        const auto log_num = find_last_log();
        last_log_is_marked_discard = false;
        write_lastlog_file(log_num);
    }

    uint32_t nbytes = _writebuf.available();
    if (nbytes == 0) {
        return;
    }
    if (nbytes < _writebuf_chunk && 
        tnow - _last_write_time < 2000UL) {
        // write in _writebuf_chunk-sized chunks, but always write at
        // least once per 2 seconds if data is available
        return;
    }

#if !AP_FILESYSTEM_LITTLEFS_ENABLED // too expensive on littlefs, rely on ENOSPC below
    if (tnow - _free_space_last_check_time > _free_space_check_interval) {
        _free_space_last_check_time = tnow;
        last_io_operation = "disk_space_avail";
        if (disk_space_avail() < _free_space_min_avail && disk_space() > 0) {
            DEV_PRINTF("Out of space for logging\n");
            stop_logging();
            _open_error_ms = AP_HAL::millis(); // prevent logging starting again for 5s
            last_io_operation = "";
            return;
        }
        last_io_operation = "";
    }
#endif
    _last_write_time = tnow;
    if (nbytes > _writebuf_chunk) {
        // be kind to the filesystem layer
        nbytes = _writebuf_chunk;
    }

    uint32_t size;
    const uint8_t *head = _writebuf.readptr(size);
    nbytes = MIN(nbytes, size);

#if !AP_FILESYSTEM_LITTLEFS_ENABLED
    // try to align writes on a 512 byte boundary to avoid filesystem reads
    if ((nbytes + _write_offset) % 512 != 0) {
        uint32_t ofs = (nbytes + _write_offset) % 512;
        if (ofs < nbytes) {
            nbytes -= ofs;
        }
    }
#endif
    last_io_operation = "write";
    if (!write_fd_semaphore.take(1)) {
        return;
    }
    if (_write_fd == -1) {
        write_fd_semaphore.give();
        return;
    }

    uint32_t bytes_until_fsync = AP::FS().bytes_until_fsync(_write_fd);
    if (bytes_until_fsync > 0 && nbytes > bytes_until_fsync) {
        nbytes = bytes_until_fsync; // write exactly enough to sync
    }

    ssize_t nwritten = AP::FS().write(_write_fd, head, nbytes);
    last_io_operation = "";
    if (nwritten <= 0) {
        if (errno == ENOSPC) {
            DEV_PRINTF("Out of space for logging\n");
            stop_logging();
            _open_error_ms = AP_HAL::millis(); // prevent logging starting again for 5s
            last_io_operation = "";
        } else if ((tnow - _last_write_ms)/1000U > unsigned(_front._params.file_timeout)) {
            // if we can't write for LOG_FILE_TIMEOUT seconds we give up and close
            // the file. This allows us to cope with temporary write
            // failures caused by directory listing
            last_io_operation = "close";
            AP::FS().close(_write_fd);
            last_io_operation = "";
            _write_fd = -1;
            printf("Failed to write to File: %s\n", strerror(errno));
        }
        _last_write_failed = true;
    } else {
        _last_write_failed = false;
        _last_write_ms = tnow;
        _write_offset += nwritten;
        _writebuf.advance(nwritten);

        // we know nwritten > 0 so we won't sync if bytes_until_fsync == 0
        if ((uint32_t)nwritten == bytes_until_fsync) {
            last_io_operation = "fsync";
            AP::FS().fsync(_write_fd);
            last_io_operation = "";
        }

#if AP_RTC_ENABLED && CONFIG_HAL_BOARD == HAL_BOARD_CHIBIOS
        // ChibiOS does not update mtime on writes, so if we opened
        // without knowing the time we should update it later
        if (_need_rtc_update) {
            uint64_t utc_usec;
            if (AP::rtc().get_utc_usec(utc_usec)) {
                AP::FS().set_mtime(_write_filename, utc_usec/(1000U*1000U));
                _need_rtc_update = false;
            }
        }
#endif
    }

    write_fd_semaphore.give();
}

bool AP_Logger_File::io_thread_alive() const
{
    if (!hal.scheduler->is_system_initialized()) {
        // the system has long pauses during initialisation, assume still OK
        return true;
    }
    // if the io thread hasn't had a heartbeat in a while then it is
#if CONFIG_HAL_BOARD == HAL_BOARD_ESP32
    uint32_t timeout_ms = 10000;
#else
    uint32_t timeout_ms = 5000;
#endif
#if CONFIG_HAL_BOARD == HAL_BOARD_SITL && !defined(HAL_BUILD_AP_PERIPH)
    // the IO thread is working with hardware - writing to a physical
    // disk.  Unfortunately these hardware devices do not obey our
    // SITL speedup options, so we allow for it here.
    SITL::SIM *sitl = AP::sitl();
    if (sitl != nullptr && sitl->speedup > 0) {
        timeout_ms *= sitl->speedup;
    }
#endif
    return (AP_HAL::millis() - _io_timer_heartbeat) < timeout_ms;
}

bool AP_Logger_File::logging_failed() const
{
    if (!_initialised) {
        return true;
    }
    if (recent_open_error()) {
        return true;
    }
    if (!io_thread_alive()) {
        // No heartbeat in a second.  IO thread is dead?! Very Not
        // Good.
        return true;
    }
    if (_last_write_failed) {
        return true;
    }

    return false;
}

/*
  erase another file in async erase operation
 */
void AP_Logger_File::erase_next(void)
{
    char *fname = _log_file_name(erase.log_num);
    if (fname == nullptr) {
        erase.log_num = 0;
        return;
    }

    AP::FS().unlink(fname);
    free(fname);

    erase.log_num++;
    if (erase.log_num <= _front.get_max_num_logs()) {
        return;
    }
    
    fname = _lastlog_file_name();
    if (fname != nullptr) {
        AP::FS().unlink(fname);
        free(fname);
    }

    _cached_oldest_log = 0;

    erase.log_num = 0;
}

#endif // HAL_LOGGING_FILESYSTEM_ENABLED

